Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Fix] Link up notifications LINK_UP_TIMER #114

Merged
merged 4 commits into from
Dec 1, 2022
Merged

Conversation

viniarck
Copy link
Member

@viniarck viniarck commented Nov 18, 2022

Fixes #101
Fixes #100
Fixes #103 (it's using notified_up_at metadata though)

  • Fixed link up to only notify when LINK_UP_TIMER has passed
  • Hooked link_status_hook_link_up_timer to update status accordingly.
  • Added notified_up_at internal reserved metadata

Now it's correctly respecting LINK_UP_TIMER, the following cases were explored locally (I've also left some requests to pathfinder in the background running for additional testing):

I'll dispatch e2e tests execution with this branch. LINK_UP_TIMER is 1 sec there, so no surprises expected, once I have the results I'll post here for completeness.

1 - Both interface go up and created in a short period:

Notice that mef_eline is notified in 10 secs more of less [2022-11-18 14:43:30,776 - INFO [kytos.napps.kytos/mef_eline] [main.py:630:on_link_up] once handshake and port description were received:

2022-11-18 14:43:20,619 - INFO [kytos.napps.kytos/of_core] [main.py:138:handle_features_reply] (thread_pool_sb_0) Connection ('127.0.0.1', 58716), Switch 00:00:00:00:00:00:00:01: OPENFL
OW HANDSHAKE COMPLETE
2022-11-18 14:43:20,622 - INFO [kytos.napps.kytos/of_core] [main.py:138:handle_features_reply] (thread_pool_sb_0) Connection ('127.0.0.1', 58722), Switch 00:00:00:00:00:00:00:03: OPENFL
OW HANDSHAKE COMPLETE
2022-11-18 14:43:20,623 - INFO [kytos.napps.kytos/of_core] [main.py:138:handle_features_reply] (thread_pool_sb_0) Connection ('127.0.0.1', 58726), Switch 00:00:00:00:00:00:00:02: OPENFL
OW HANDSHAKE COMPLETE
2022-11-18 14:43:20,659 - INFO [kytos.napps.kytos/flow_manager] [main.py:588:_send_flow_mods_from_request] (Thread-94) Send FlowMod from request dpid: 00:00:00:00:00:00:00:03, command:
add, force: False, flows_dict: {'flows': [{'priority': 1000, 'table_id': 0, 'cookie': 12321848580485677059, 'match': {'dl_type': 35020, 'dl_vlan': 3799}, 'actions': [{'action_type': 'output', 'port': 4294967293}]}]}
2022-11-18 14:43:20,662 - INFO [kytos.napps.kytos/flow_manager] [main.py:588:_send_flow_mods_from_request] (Thread-95) Send FlowMod from request dpid: 00:00:00:00:00:00:00:01, command:
add, force: True, flows_dict: {'flows': [{'table_id': 0, 'match': {'dl_src': 'ee:ee:ee:ee:ee:02'}, 'priority': 50000, 'actions': [{'action_type': 'output', 'port': 4294967293}], 'cookie
': 12393906174523604993}], 'force': True}
2022-11-18 14:43:20,666 - INFO [kytos.napps.kytos/flow_manager] [main.py:588:_send_flow_mods_from_request] (Thread-96) Send FlowMod from request dpid: 00:00:00:00:00:00:00:01, command:
add, force: False, flows_dict: {'flows': [{'priority': 1000, 'table_id': 0, 'cookie': 12321848580485677057, 'match': {'dl_type': 35020, 'dl_vlan': 3799}, 'actions': [{'action_type': 'ou
tput', 'port': 4294967293}]}]}
2022-11-18 14:43:20,676 - INFO [werkzeug] [_internal.py:225:_log] (Thread-96) 127.0.0.1 - - [18/Nov/2022 14:43:20] "POST /api/kytos/flow_manager/v2/flows/00:00:00:00:00:00:00:01 HTTP/1.
1" 202 -
2022-11-18 14:43:20,679 - INFO [werkzeug] [_internal.py:225:_log] (Thread-95) 127.0.0.1 - - [18/Nov/2022 14:43:20] "POST /api/kytos/flow_manager/v2/flows/00:00:00:00:00:00:00:01 HTTP/1.
1" 202 -
kytos $> 2022-11-18 14:43:26,401 - INFO [werkzeug] [_internal.py:225:_log] (Thread-105) 127.0.0.1 - - [18/Nov/2022 14:43:26] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:43:27,418 - INFO [werkzeug] [_internal.py:225:_log] (Thread-106) 127.0.0.1 - - [18/Nov/2022 14:43:27] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:43:28,432 - INFO [werkzeug] [_internal.py:225:_log] (Thread-107) 127.0.0.1 - - [18/Nov/2022 14:43:28] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:43:29,454 - INFO [werkzeug] [_internal.py:225:_log] (Thread-108) 127.0.0.1 - - [18/Nov/2022 14:43:29] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:43:30,482 - INFO [werkzeug] [_internal.py:225:_log] (Thread-109) 127.0.0.1 - - [18/Nov/2022 14:43:30] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:43:30,774 - INFO [kytos.napps.kytos/mef_eline] [main.py:630:on_link_up] (thread_pool_app_5) on_link_up {'link': Link(Interface('s2-eth3', 3, Switch('00:00:00:00:00:00:00:0
2')), Interface('s3-eth2', 2, Switch('00:00:00:00:00:00:00:03'))), 'reason': 'link up'}
2022-11-18 14:43:30,776 - INFO [kytos.napps.kytos/mef_eline] [main.py:630:on_link_up] (thread_pool_app_4) on_link_up {'link': Link(Interface('s1-eth2', 2, Switch('00:00:00:00:00:00:00:0
1')), Interface('s2-eth2', 2, Switch('00:00:00:00:00:00:00:02'))), 'reason': 'link up'}

2 - Set interface down and up shortly after:

2022-11-18 14:44:09,395 - INFO [werkzeug] [_internal.py:225:_log] (Thread-124) 127.0.0.1 - - [18/Nov/2022 14:44:09] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:44:09,948 - INFO [kytos.napps.kytos/of_core] [main.py:600:update_port_status] (MainThread) Modified Interface('s1-eth2', 2, Switch('00:00:00:00:00:00:00:01')) 00:00:00:00:
00:00:00:01:2
2022-11-18 14:44:09,950 - INFO [kytos.napps.kytos/of_core] [main.py:600:update_port_status] (MainThread) Modified Interface('s2-eth2', 2, Switch('00:00:00:00:00:00:00:02')) 00:00:00:00:
00:00:00:02:2
2022-11-18 14:44:10,418 - INFO [werkzeug] [_internal.py:225:_log] (Thread-125) 127.0.0.1 - - [18/Nov/2022 14:44:10] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:44:11,434 - INFO [werkzeug] [_internal.py:225:_log] (Thread-126) 127.0.0.1 - - [18/Nov/2022 14:44:11] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:44:12,444 - INFO [werkzeug] [_internal.py:225:_log] (Thread-127) 127.0.0.1 - - [18/Nov/2022 14:44:12] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:44:13,467 - INFO [werkzeug] [_internal.py:225:_log] (Thread-128) 127.0.0.1 - - [18/Nov/2022 14:44:13] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:44:14,483 - INFO [werkzeug] [_internal.py:225:_log] (Thread-129) 127.0.0.1 - - [18/Nov/2022 14:44:14] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:44:15,495 - INFO [werkzeug] [_internal.py:225:_log] (Thread-130) 127.0.0.1 - - [18/Nov/2022 14:44:15] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:44:16,506 - INFO [werkzeug] [_internal.py:225:_log] (Thread-131) 127.0.0.1 - - [18/Nov/2022 14:44:16] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:44:17,516 - INFO [werkzeug] [_internal.py:225:_log] (Thread-132) 127.0.0.1 - - [18/Nov/2022 14:44:17] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:44:18,539 - INFO [werkzeug] [_internal.py:225:_log] (Thread-136) 127.0.0.1 - - [18/Nov/2022 14:44:18] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:44:19,550 - INFO [werkzeug] [_internal.py:225:_log] (Thread-137) 127.0.0.1 - - [18/Nov/2022 14:44:19] "POST /api/kytos/pathfinder/v2 HTTP/1.1" 200 -
2022-11-18 14:44:19,988 - INFO [kytos.napps.kytos/mef_eline] [main.py:630:on_link_up] (thread_pool_app_7) on_link_up {'link': Link(Interface('s1-eth2', 2, Switch('00:00:00:00:00:00:00:0
1')), Interface('s2-eth2', 2, Switch('00:00:00:00:00:00:00:02'))), 'reason': 'link up'}

3 - Make sure it's working well with liveness since it's relying on status:

Notice that it notified link up only once, even if liveness detects it faster, but since it's now integrated with stauts and status_funcs then it respects accordingly:

2022-11-18 14:57:29,542 - INFO [kytos.napps.kytos/topology] [main.py:572:handle_link_liveness_status] (thread_pool_app_6) Link liveness up: Link(Interface('s2-eth2', 2, Switch('00:00:00:
00:00:00:00:02')), Interface('s1-eth2', 2, Switch('00:00:00:00:00:00:00:01')))
2022-11-18 14:57:29,546 - INFO [kytos.napps.kytos/topology] [main.py:572:handle_link_liveness_status] (thread_pool_app_9) Link liveness up: Link(Interface('s2-eth3', 3, Switch('00:00:00:
00:00:00:00:02')), Interface('s3-eth2', 2, Switch('00:00:00:00:00:00:00:03')))
2022-11-18 14:57:30,718 - INFO [werkzeug] [_internal.py:225:_log] (Thread-100) 127.0.0.1 - - [18/Nov/2022 14:57:30] "GET /api/kytos/of_lldp/v1/liveness/pair HTTP/1.1" 200 -
2022-11-18 14:57:31,286 - INFO [werkzeug] [_internal.py:225:_log] (Thread-101) 127.0.0.1 - - [18/Nov/2022 14:57:31] "GET /api/kytos/of_lldp/v1/liveness/pair HTTP/1.1" 200 -
2022-11-18 14:57:32,071 - INFO [werkzeug] [_internal.py:225:_log] (Thread-102) 127.0.0.1 - - [18/Nov/2022 14:57:32] "GET /api/kytos/of_lldp/v1/liveness/pair HTTP/1.1" 200 -
kytos $>

kytos $> 2022-11-18 14:57:39,348 - INFO [kytos.napps.kytos/mef_eline] [main.py:630:on_link_up] (thread_pool_app_1) on_link_up {'link': Link(Interface('s1-eth2', 2, Switch('00:00:00:00:00
:00:00:01')), Interface('s2-eth2', 2, Switch('00:00:00:00:00:00:00:02'))), 'reason': 'link up'}
2022-11-18 14:57:39,350 - INFO [kytos.napps.kytos/mef_eline] [main.py:630:on_link_up] (thread_pool_app_5) on_link_up {'link': Link(Interface('s3-eth2', 2, Switch('00:00:00:00:00:00:00:03
')), Interface('s2-eth3', 3, Switch('00:00:00:00:00:00:00:02'))), 'reason': 'link up'}

Added link_status_hook_link_up_timer
Added notify_link_up_if_status to be reused
Reused notify_link_up_if_status when creating a link
@viniarck
Copy link
Member Author

Here's the result of e2e tests, had 1 rerun but it's not a side effect of this change:

=========================== rerun test summary info ============================
RERUN tests/test_e2e_20_flow_manager.py::TestE2EFlowManager::test_030_modify_match
= 164 passed, 2 skipped, 18 xfailed, 7 xpassed, 758 warnings, 1 rerun in 10195.09s (2:49:55) =

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
1 participant